fix(postgres): prevent first-sync lsn mismatch under concurrent write load - #1084
fix(postgres): prevent first-sync lsn mismatch under concurrent write load#1084mihir-datazip wants to merge 4 commits into
Conversation
…nc lsn mismatch pg_replication_slot_advance silently clamps its target to the flushed WAL position, so under concurrent write load the slot stopped short of the pg_current_wal_lsn() bookmark PreCDC had just written to state, and the next validation failed with "lsn mismatch, please proceed with clear destination" on a healthy pipeline. AdvanceLSN now reads the end_lsn the advance returns and re-advances until the slot confirms the target; PreCDC seeds state only after that confirmation.
9d22a0e to
08e917b
Compare
6995467 to
a831b09
Compare
| var slotName string | ||
| var endLSN pglogrepl.LSN |
There was a problem hiding this comment.
Can we remove this slotName variable from here if it is redundant?
| if err := db.QueryRowContext(timeoutCtx, fmt.Sprintf(AdvanceLSNTemplate, slot, currentWalPos)).Scan(&slotName, &endLSN); err != nil { | ||
| return fmt.Errorf("failed to advance replication slot: %w", err) | ||
| } |
There was a problem hiding this comment.
I understand why we're using timeoutCtx here, but I noticed that elsewhere in the codebase, QueryRowContext is used with the regular ctx. Do we need the timeout specifically here, or should we keep it consistent with the rest of the codebase? Is there any specific reason for using timeoutCtx here?
| return fmt.Errorf("slot advance stopped at %s and could not reach target %s: %w", endLSN, target, timeoutCtx.Err()) | ||
| case <-time.After(100 * time.Millisecond): |
There was a problem hiding this comment.
We do not use %w in our codebase for normal error,we use it for non-retryable error?If changing also look for other error messages as well.
| if endLSN >= target { | ||
| logger.Debugf("advanced LSN to %s", currentWalPos) |
There was a problem hiding this comment.
Here we have >= check but when > check will be possible over here ?
And suppose it is possible than shouldn't we set endLSN in globalState instead of target ?
Description
On a pipeline's first CDC sync,
PreCDCbookmarks the resume position by readingpg_current_wal_lsn()into the state file and advancing the replication slot to the same value. Two PostgreSQL behaviours break the intendedstate == confirmed_flush_lsninvariant:pg_current_wal_lsn()returns the WAL write pointer, which runs ahead of the fsynced flush pointer whenever WAL is written faster than it is flushed (bulk statements, async commits).pg_replication_slot_advance()silently clamps its target to the flushed position, and reports where the slot really stopped only in itsend_lsnresult column — whichAdvanceLSNdiscarded (db.ExecContext, result ignored).So under concurrent write load the state file records the write pointer while the slot stops at the flush pointer.
validateGlobalStatedemands strict equality, so the sync dies at its CDC phase — and every retry after it — with:…telling the user to wipe the destination and re-backfill a perfectly healthy pipeline. Only the bootstrap path is affected:
AcknowledgeLSNalready polls the slot until it confirms, so post-bootstrap syncs are safe.When it appears — measured (stock postgres:15,
wal_buffers= 4 MB default, local NVMe)Sync-commit workloads — the trigger is any single statement/transaction writing more WAL than
wal_buffers:wal_buffers(0.5–2 MB WAL/stmt, ~100–170k rows/s)wal_buffers(4 MB WAL/stmt, ~182k rows/s)Per-bootstrap hit probability measured ~3.5% beside 30 MB statements — consistent with the field observation of a 432-byte mismatch roughly once per ~60 first syncs on a near-idle test database.
Async-commit workloads (
synchronous_commit = off, a documented and common knob for ingest/ETL pipelines) — commits stop closing the window, so any rate is exposed:Local NVMe is the conservative case: slower (cloud) storage widens the write-vs-flush window.
The fix
waljs.AdvanceLSNnow reads theend_lsnthe advance returns. When it lands short of the request the advance was clamped, so it waits 100 ms (the walwriter closes the gap within ~3×wal_writer_delay) and re-advances until the slot confirms the target. A 30 s cap turns a pathological stall into a clear, retryable error instead of a bricked pipeline. Function signature unchanged.PreCDCseeds the state after the slot has confirmed, sostate == confirmed_flush_lsnholds by construction — and a failed advance no longer leaves a seeded state behind (the write-ordering gap fix(postgres): reverse write ordering in PreCDC/PostCDC to prevent LSN mismatch #854 flagged on this path).Type of change
How Has This Been Tested?
Verified with a two-test repro harness, kept out of this PR's diff — full source in the collapsed block at the bottom of this section (drop
cdc_bootstrap_repro_test.gointodrivers/postgres/internal/and run the command below; it skips withoutOLAKE_PG_REPRO_DSN). Both tests replay the exact PreCDC bootstrap plus the next sync's validation against a live postgres while a load generator runs, ramping load level by level and failing with full forensics on the first divergence:TestReproPreCDCBootstrapLSNDivergence— defaultsynchronous_commit, ramps bulk-statement size 0.5 → 32 MB WAL/stmt across thewal_buffersboundary.TestReproPreCDCBootstrapLSNDivergenceAsyncCommit— load session undersynchronous_commit = off, ramps small-statement rate from 5 stmt/s to unthrottled.gofmt/go vetclean onpkg/waljsanddrivers/postgresBefore the fix — both ladders reproduce
After the fix — invariant held at every level of both ladders
Full repro harness — cdc_bootstrap_repro_test.go
Screenshots or Recordings
N/A — terminal outputs attached above.
Documentation
Related PR's (If Any):